Android Framework

Binder 驱动 Debug 入门指南

8/12/2023

# 什么是 Debugfs

DebugFS，是一种用于内核调试的虚拟文件系统，内核中提供了相应的函数，将一些日志信息写入这个虚拟文件系统，内核的使用者通过查看这个虚拟文件系统对应的文件，即可了解内核中对用模块的运行状况。

# Debugfs 中的 Binder

debugfs 文件系统默认挂载在节点 /sys/kernel/debug，binder 驱动初始化的过程会在该节点下先创建 /binder 目录，然后在该目录下创建下面文件和目录：

  • proc
  • stats
  • state
  • transactions
  • transaction_log
  • failed_transaction_log

在 binder 驱动的 binder_init 函数中：

// drivers/android/binder.c
static int __init binder_init(void)
{
	
    //.....

    // 在 /sys/kernel/debug 目录下创建 binder 文件夹
	binder_debugfs_dir_entry_root = debugfs_create_dir("binder", NULL);
	if (binder_debugfs_dir_entry_root)
		binder_debugfs_dir_entry_proc = debugfs_create_dir("proc",
						 binder_debugfs_dir_entry_root);

	if (binder_debugfs_dir_entry_root) {
        // 在 /sys/kernel/debug 目录下创建 binder 文件夹
		debugfs_create_file("state",
				    0444,
				    binder_debugfs_dir_entry_root,
				    NULL,
				    &binder_state_fops);
		debugfs_create_file("stats",
				    0444,
				    binder_debugfs_dir_entry_root,
				    NULL,
				    &binder_stats_fops);
		debugfs_create_file("transactions",
				    0444,
				    binder_debugfs_dir_entry_root,
				    NULL,
				    &binder_transactions_fops);
		debugfs_create_file("transaction_log",
				    0444,
				    binder_debugfs_dir_entry_root,
				    &binder_transaction_log,
				    &binder_transaction_log_fops);
		debugfs_create_file("failed_transaction_log",
				    0444,
				    binder_debugfs_dir_entry_root,
				    &binder_transaction_log_failed,
				    &binder_transaction_log_fops);
	}

// ......
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43

binder 相关的调试文件就是通过上述的代码完成创建的。

在 binder 驱动源码中有很多 binder_debug 函数调用：

	binder_debug(BINDER_DEBUG_OPEN_CLOSE,
		     "%s: %d threads %d, nodes %d (ref %d), refs %d, active transactions %d\n",
		     __func__, proc->pid, threads, nodes, incoming_refs,
		     outgoing_refs, active_transactions);

	binder_debug(BINDER_DEBUG_SPINLOCKS,
		     "%s: line=%d\n", __func__, line);

    binder_debug(BINDER_DEBUG_INTERNAL_REFS,
					     "refless node %d deleted\n",
					     node->debug_id);

    //......
1
2
3
4
5
6
7
8
9
10
11
12
13

binder_debug 函数会把日志信息写入到我们创建好的 debugfs 中的文件中。binder_debug 的第一个参数叫 debug_mask，它决定了我们日志的类型与日志所在的文件。

# 内核模块参数

有的时候，在执行一些内核模块时，需要我们传入一些参数，内核提供了 module_param 宏来实现这个功能：

//假设模块名为 xxx
//定义一个内核模块参数
static unsigned int int_var = 0;
module_param(int_var, uint, S_IRUGO);
1
2
3
4

上面的代码定义了一个模块参数 int_var，我们可以在执行模块时传入参数值：

//执行内核模块时，传入参数
insmod xxx.ko int_var=x
1
2

除了在执行时传入参数值，我们还可以通过写文件来传参数：每一个模块参数会对应一个文件 /sys/module/模块名/parameters/参数名，上面的示例中的模块参数对应的文件就是 /sys/module/xxx/parameters/int_var，那么我们通过写这个文件就能把参数传入模块中，向文件写数据，我们可以通过 C 语言实现，也可以使用 shell 命令实现，这里我们给一个 shell 脚本的例子：

echo 8 > /sys/module/xxx/parameters/int_var
1

执行完这个命令后，在模块中的 int_var 参数的值就变成 8 了。

回过头来，module_param 的具体实现如下：

#define module_param(name, type, perm)				\
	module_param_named(name, name, type, perm)
1
2

可以看出 module_param 就是 module_param_named 的马甲：

// module_param_named 的具体实现就不再深入了，了解功能即可，这个不是本文重点
#define module_param_named(name, value, type, perm)			   \
	param_check_##type(name, &(value));				   \
	module_param_cb(name, &param_ops_##type, &value, perm);		   \
	__MODULE_PARM_TYPE(name, #type)
1
2
3
4
5

module_param_named 相比 module_param ，可以给模块参数一个初始值 value。

# Binder 驱动中的模块参数

在 Binder 驱动中都是使用的 module_param_named 来定义模块参数。接下来我们来看一个 Binder 驱动中的模块参数 debug_mask，其定义如下：

static uint32_t binder_debug_mask = BINDER_DEBUG_USER_ERROR |
	BINDER_DEBUG_FAILED_TRANSACTION | BINDER_DEBUG_DEAD_TRANSACTION;
module_param_named(debug_mask, binder_debug_mask, uint, 0644);
1
2
3

上面的代码执行后，就会生成对应的文件 /sys/module/binder/parameters/debug_mask，当我们修改这个文件的值时，就会修改 Binder 驱动中 debug_mask 的值。

debug_mask 是一个无符号整型，有一个初始值 binder_debug_mask，这个模块参数扮演了 Log 开关的角色，通过设置 debug_mask 的值可以打印我们需要的 Log 信息。debug_mask 通过二进制或操作设置 uint32_t 类型中的每一个位的值来决定其功能。

具体来说，debug_mask 有以下一些可选值：

类型 二进制值 解释
BINDER_DEBUG_USER_ERROR 1 用户使用错误
BINDER_DEBUG_FAILED_TRANSACTION 10 transaction失败
BINDER_DEBUG_DEAD_TRANSACTION 100 transaction死亡
BINDER_DEBUG_OPEN_CLOSE 1000 binder的open/close/mmap信息
BINDER_DEBUG_DEAD_BINDER 10000 binder/node死亡信息
BINDER_DEBUG_DEATH_NOTIFICATION 100000 binder死亡通知信息
BINDER_DEBUG_READ_WRITE 1000000 binder的read/write信息
BINDER_DEBUG_USER_REFS 10000000 binder引用计数
BINDER_DEBUG_THREADS 100000000 binder_thread信息
BINDER_DEBUG_TRANSACTION 1000000000 transaction信息
BINDER_DEBUG_TRANSACTION_COMPLETE 10000000000 transaction完成信息
BINDER_DEBUG_FREE_BUFFER 100000000000 可用buffer信息
undefinedBINDER_DEBUG_INTERNAL_REFS 1000000000000 binder内部引用计数
BINDER_DEBUG_BUFFER_ALLOC 10000000000000 同步内存分配信息
BINDER_DEBUG_PRIORITY_CAP 100000000000000 调整binder线程的nice值
BINDER_DEBUG_BUFFER_ALLOC_ASYNC 1000000000000000 异步内存分配信息

比如我们需要打印 transaction 失败 与 transaction死亡 信息，那么我们就可以把 binder_debug_mask 的值设置为 10 | 100 = 110 即十进制的 6 即可：

echo 6 > /sys/module/binder/parameters/debug_mask
1

在内核源码中我们使用 binder_debug 打印 Log 信息到 debugfs 文件系统中：

#define binder_debug(mask, x...) \
	do { \
		if (binder_debug_mask & mask) \
			pr_info(x); \
	} while (0)
1
2
3
4
5

我们也可以通过 binder_debug 的第一个参数来添加 binder_debug_mask 的值。

# 节点分析

在进行 Binder debug 或分析问题时，通常需要看一下当前的 Binder 状态信息。Kernel 通过 SYS 系统提供了一些文件节点供我们读取，它们位于 /sys/kernel/debug/binder/，分别为：

  • Stats：Binder传输的统计信息。
  • State：当前Binder所有进程的状态。
  • Transactions：当前Binder所有进程的传输状态。
  • transaction_log：最近的Binder传输。
  • failed_transaction_log：最近失败的Binder传输。

# Stats

Stats 包含的 Binder 的统计信息，包括传输命令的统计，内部对象的统计等。开始输出的是全部 Binder 的统计信息，之后按 Binder 进程逐个输出统计信息。

通过

cat /sys/kernel/debug/binder/stats
1

命令即可查看 Stats 信息：

binder stats:
#  Binder BC 命令计数
BC_TRANSACTION: 21561
BC_REPLY: 19102
BC_FREE_BUFFER: 97947
BC_INCREFS: 12458
BC_ACQUIRE: 12650
BC_RELEASE: 10812
BC_DECREFS: 10156
BC_INCREFS_DONE: 10691
BC_ACQUIRE_DONE: 10692
BC_REGISTER_LOOPER: 145
BC_ENTER_LOOPER: 132
BC_REQUEST_DEATH_NOTIFICATION: 861
BC_CLEAR_DEATH_NOTIFICATION: 374
BC_DEAD_BINDER_DONE: 14
BC_TRANSACTION_SG: 33879
BC_REPLY_SG: 23474
# Binder BR 返回命令计数
BR_TRANSACTION: 55440
BR_REPLY: 42575
BR_TRANSACTION_COMPLETE: 98014
BR_INCREFS: 10704
BR_ACQUIRE: 10705
BR_RELEASE: 9793
BR_DECREFS: 9781
BR_SPAWN_LOOPER: 149
BR_DEAD_BINDER: 16
BR_CLEAR_DEATH_NOTIFICATION_DONE: 374

# Binder 内部对象计数，active 表示有效的对象数量，total 表示开机到现在总共创建的对象数量
proc: active 99 total 1336
thread: active 456 total 1992
node: active 912 total 10843
ref: active 1720 total 12622
death: active 484 total 861
transaction: active 1 total 98016
transaction_complete: active 1 total 98016

# 进程 PID
proc 3257
context binder
  threads: 4 # Binder 线程数
  requested threads: 0+1/15 # 请求线程数 + 已启动线程数/最大线程数
  ready threads 2           # 已经准备好的线程数
  free async space 520192   # 异步传输可用空间，单位字节
  nodes: 5                  # binder_node 结构体数量  
  refs: 24 s 24 w 24        # 引用计数， s 强 w 弱
  buffers: 0                # allocated_buffers (已分配的buffer个数)
  pages: 0:2:252            # page 相关信息
  pages high watermark: 2
  pending transactions: 0   # proc 的 todo 队列事务个数

  # 当前进程 binder BC 命令计数
  BC_TRANSACTION: 32
  BC_FREE_BUFFER: 34
  BC_INCREFS: 25
  BC_ACQUIRE: 25
  BC_RELEASE: 1
  BC_DECREFS: 1
  BC_INCREFS_DONE: 5
  BC_ACQUIRE_DONE: 5
  BC_REGISTER_LOOPER: 1
  BC_ENTER_LOOPER: 1
  # 当前进程 Binder BR 返回命令计数
  BR_TRANSACTION: 3
  BR_REPLY: 31
  BR_TRANSACTION_COMPLETE: 32
  BR_INCREFS: 5
  BR_ACQUIRE: 5
  BR_SPAWN_LOOPER: 1

  # ...... 其他进程信息
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73

命令计数的规律如下: BC_TRANSACTION + BC_REPLY = BR_TRANSACTION_COMPLETE + BR_DEAD_REPLY + BR_FAILED_REPLY

为什么是会是这样呢,因为每次 BC_TRANSACTION 或着 BC_REPLY,都是有相应的 BR_TRANSACTION_COMPLETE,在传输不出异常的情况下这个次数是相等,有时候可能 transaction 失败, 所以还需要加上 BR_DEAD_REPLY 和 BR_FAILED_REPLY 的情况.

  • 当 binder 内存紧张时，可查看 free async space 和 buffers 字段
  • 当系统空闲时，一般来说 ready_threads = requested_threads_started + BC_ENTER_LOOPER； 当系统繁忙时 ready_threads 可能为0。例如 system_server 进程的 ready_threads 线程个数越少，系统可能处于越繁忙的状态；
  • 绝大多数的进程 max_threads = 15，而 surfaceflinger 最大线程个数为 4，servicemanager 最大线程个数为 0(只有主线程)；

举个实际的例子：想查看当前系统所有进程的异步可用内存情况，可执行：

adb shell cat /d/binder/stats | egrep "proc|free async space"
1

# State

State 中主要记录了当前所有进程的 Binder 状态。

通过

cat /sys/kernel/debug/binder/state
1

命令即可查看 State 信息：

binder state:
# 死亡节点的信息
# 记录的时死亡的 Binder（dead node）。因为这些Binder的进程已经死掉，它们当前不属于任何进程，所以将它们记录在一个全局的队列中（binder_proc 的 binder_dead_nodes 中）
dead nodes:        
  node 34015: u00007231e521b760 c00007231e518cdd0 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
  node 33574: u00007231e521b6e0 c00007231e50c2170 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
  node 14081: u00007231e521b3c0 c00007231e50c1040 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
  node 14079: u00007231e521b200 c00007231e5183610 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
  node 13553: u00007231e52117a0 c00007231e518cdd0 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
  node 13164: u00007231e5211240 c00007231e50c2170 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
  node 29997: u00007231e521b9a0 c00007231e518cdd0 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
  node 29915: u00007231e521b960 c00007231e50c2170 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
  node 31122: u0000723154d204c0 c00007231e50c1540 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
  node 35433: u00007231e521b9a0 c00007231e518cdd0 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
  node 35303: u00007231e521b960 c00007231e50c2170 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
  node 660: u00007bd4d168a7a0 c00007bd4d16066f8 pri 0:120 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772

  # ......
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18

开头信息记录的是死亡的 Binder（dead node）。因为这些 Binder 的进程已经死掉，它们当前不属于任何进程，所以将它们记录在一个全局的队列中（binder_proc 的 binder_dead_nodes 中）

我们来看下第一个 node：

 # debug_id   ptr               cookie     
 node 34015: u00007231e521b760 c00007231e518cdd0 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
1
2
  • 34015：对应 binder_node 中的 debug_id
  • u00007231e521b760：对应 binder_node 中的 ptr
  • c00007231e518cdd0：对应 binder_node 中的 cookie
  • hs：对应 binder_node 中的 has_strong_ref，表示是否存在强引用
  • hw：对应 binder_node 中的 has_weak_ref，表示是否存在弱引用
  • ls：对应 binder_node 中的 local_strong_refs，表示是否存在驱动内部的 binder 强引用计数
  • lw：对应 binder_node 中的 local_weak_refs，表示驱动内部的 binder 弱引用计数
  • is: 对应 binder_node 中的 internal_strong_refs，表示 binder node 的外部强引用计数
  • iw：binder_ref 的引用数
  • proc：对应的进程 pid

我们接着往下看，就是进程相关的信息了：

# 进程 pid
proc 3257
# 线程状态
context binder
  thread 3257: l 00 need_return 0 tr 0
  thread 3270: l 00 need_return 0 tr 0
  thread 3273: l 12 need_return 0 tr 0
  thread 3274: l 11 need_return 0 tr 0
  # binder node 信息
  node 56400: u0000723154c2d5a0 c00007231e50c0fa0 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
  node 56414: u0000723154c2d640 c00007231e50c1130 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
  node 56402: u0000723154c2d6e0 c00007231e50c1090 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
  node 56346: u00007231e5280220 c00007231e50c0aa0 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772
  node 56376: u00007231e52802a0 c00007231e50c0af0 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 1772

  # binder ref 信息
  ref 56341: desc 0 node 1 s 1 w 1 d 0000000000000000
  ref 56344: desc 1 node 2125 s 1 w 1 d 0000000000000000
  ref 56349: desc 2 node 1663 s 1 w 1 d 0000000000000000
  ref 56350: desc 3 node 2727 s 1 w 1 d 0000000000000000
  ref 56351: desc 4 node 3729 s 1 w 1 d 0000000000000000
  ref 56352: desc 5 node 2078 s 1 w 1 d 0000000000000000
  ref 56353: desc 6 node 2844 s 1 w 1 d 0000000000000000
  ref 56354: desc 7 node 2969 s 1 w 1 d 0000000000000000
  ref 56355: desc 8 node 2116 s 1 w 1 d 0000000000000000
  ref 56356: desc 9 node 2788 s 1 w 1 d 0000000000000000
  ref 56357: desc 10 node 2848 s 1 w 1 d 0000000000000000
  ref 56358: desc 11 node 2996 s 1 w 1 d 0000000000000000
  ref 56359: desc 12 node 1712 s 1 w 1 d 0000000000000000
  ref 56360: desc 13 node 3304 s 1 w 1 d 0000000000000000
  ref 56361: desc 14 node 2731 s 1 w 1 d 0000000000000000
  ref 56362: desc 15 node 2965 s 1 w 1 d 0000000000000000
  ref 56363: desc 16 node 3669 s 1 w 1 d 0000000000000000
  ref 56364: desc 17 node 2774 s 1 w 1 d 0000000000000000
  ref 56365: desc 18 node 1790 s 1 w 1 d 0000000000000000
  ref 56366: desc 19 node 3270 s 1 w 1 d 0000000000000000
  ref 56367: desc 20 node 3136 s 1 w 1 d 0000000000000000
  ref 56419: desc 21 node 5111 s 1 w 1 d 0000000000000000
  ref 56421: desc 22 node 56420 s 1 w 1 d 0000000000000000
  ref 56426: desc 23 node 378 s 1 w 1 d 0000000000000000
  
  # binder buffer 信息
  buffer 32426: 0000000000000000 size 4:0:0 delivered
  buffer 20810: 0000000000000000 size 8:0:0 delivered
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44

# Transactions

Transactions 中记录了当前系统中所有 Binder 进程的传输状态:

binder transactions:
context binder
  #buffer id    数据地址     数据长度与偏移量  active/delivered
  buffer 29494: 0000000000000000 size 8:0:0 delivered
  buffer 35759: 0000000000000000 size 52:8:0 delivered
1
2
3
4
5

# transaction_log 和 failed_transaction_log

transaction_log 中记录了最近的 Binder 传输，failed_transaction_log 中记录了最近失败的 Binder 传输。

121480: call  from 1912:2231 to 1408:0 context binder node 1 handle 0 size 100:0 ret 0/0 l=0
121481: reply from 1408:1408 to 1912:2231 context binder node 0 handle 0 size 4:0 ret 0/0 l=0
1
2
  • 121438: debug_id
  • reply from 和 call from : call_type
  • from 1524:1524 to 1772:1848 ：from_proc:from_thread to_proc:to_thread
  • node 1：to_node
  • handle：target_handle
  • size 100:0：data_size:offsets_size

# 参考资料

031.Binder 匿名服务源码分析